Dec 02 11:48:33.122 INFO testing vigil-reporter-1.0.3 against master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61 for beta-1.31-5
Dec 02 11:48:33.122 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 02 11:48:33.310 INFO [stdout] b0a2dcb7b2daf12bbdc8d878bcaaf3c523558f5d3365e79f51f26b74bbabe07c
Dec 02 11:48:33.313 INFO running `"docker" "start" "-a" "b0a2dcb7b2daf12bbdc8d878bcaaf3c523558f5d3365e79f51f26b74bbabe07c"`
Dec 02 11:48:33.722 INFO [stderr] usermod: no changes
Dec 02 11:48:34.022 INFO [stderr]    Compiling sys-info v0.5.6
Dec 02 11:48:34.023 INFO [stderr]    Compiling hyper v0.11.27
Dec 02 11:48:34.023 INFO [stderr]    Compiling tokio-tls v0.1.4
Dec 02 11:48:45.885 INFO [stderr]    Compiling hyper-tls v0.1.4
Dec 02 11:48:49.702 INFO [stderr]    Compiling reqwest v0.8.8
Dec 02 11:48:58.851 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 02 11:49:04.687 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 30.94s
Dec 02 11:49:04.704 INFO [stderr] su: No module specific data is present
Dec 02 11:49:05.177 INFO running `"docker" "inspect" "b0a2dcb7b2daf12bbdc8d878bcaaf3c523558f5d3365e79f51f26b74bbabe07c"`
Dec 02 11:49:05.356 INFO running `"docker" "rm" "-f" "b0a2dcb7b2daf12bbdc8d878bcaaf3c523558f5d3365e79f51f26b74bbabe07c"`
Dec 02 11:49:05.473 INFO [stdout] b0a2dcb7b2daf12bbdc8d878bcaaf3c523558f5d3365e79f51f26b74bbabe07c
Dec 02 11:49:05.475 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 02 11:49:05.678 INFO [stdout] 2e14c06f36b1a7c8bd2baae853c51ae15fa6c6dc137eb06b3d7eda48728b774e
Dec 02 11:49:05.680 INFO running `"docker" "start" "-a" "2e14c06f36b1a7c8bd2baae853c51ae15fa6c6dc137eb06b3d7eda48728b774e"`
Dec 02 11:49:06.180 INFO [stderr] usermod: no changes
Dec 02 11:49:06.411 INFO [stderr]    Compiling vigil-reporter v1.0.3 (/source)
Dec 02 11:49:20.573 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 14.38s
Dec 02 11:49:20.595 INFO [stderr] su: No module specific data is present
Dec 02 11:49:22.474 INFO running `"docker" "inspect" "2e14c06f36b1a7c8bd2baae853c51ae15fa6c6dc137eb06b3d7eda48728b774e"`
Dec 02 11:49:22.753 INFO running `"docker" "rm" "-f" "2e14c06f36b1a7c8bd2baae853c51ae15fa6c6dc137eb06b3d7eda48728b774e"`
Dec 02 11:49:23.087 INFO [stdout] 2e14c06f36b1a7c8bd2baae853c51ae15fa6c6dc137eb06b3d7eda48728b774e
Dec 02 11:49:23.091 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-7/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 02 11:49:23.586 INFO [stdout] f70fc6973df4bd7133c9a55896e629e341a3af3615ccf9cd35a82811b3b78df1
Dec 02 11:49:23.589 INFO running `"docker" "start" "-a" "f70fc6973df4bd7133c9a55896e629e341a3af3615ccf9cd35a82811b3b78df1"`
Dec 02 11:49:24.863 INFO [stderr] usermod: no changes
Dec 02 11:49:25.274 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.38s
Dec 02 11:49:25.309 INFO [stderr]      Running /target/debug/deps/vigil_reporter-59e779ec618e472b
Dec 02 11:49:25.335 INFO [stdout] 
Dec 02 11:49:25.335 INFO [stdout] running 0 tests
Dec 02 11:49:25.335 INFO [stdout] 
Dec 02 11:49:25.335 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 02 11:49:25.335 INFO [stdout] 
Dec 02 11:49:25.335 INFO [stderr]      Running /target/debug/deps/report-118791da84005585
Dec 02 11:49:25.339 INFO [stdout] 
Dec 02 11:49:25.339 INFO [stdout] running 5 tests
Dec 02 11:49:25.355 INFO [stdout] test initialize_valid ... ok
Dec 02 11:49:25.355 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: vigil_reporter: Vigil Reporter: Will run using URL: http://status.example.com.local
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: tokio_threadpool::builder: build; num-workers=8
Dec 02 11:49:25.375 INFO [stderr] TRACE 2018-12-02T11:49:25Z: mio::poll: registering with poller
Dec 02 11:49:25.375 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: tokio_core::reactor: consuming notification queue
Dec 02 11:49:25.375 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: tokio_core::reactor: loop poll - 61.317µs
Dec 02 11:49:25.375 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: tokio_core::reactor: loop time - Instant { tv_sec: 5424541, tv_nsec: 253133961 }
Dec 02 11:49:25.375 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: tokio_core::reactor: loop process, 48.22µs
Dec 02 11:49:25.383 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: tokio_reactor::background: starting background reactor
Dec 02 11:49:25.391 INFO [stderr] DEBUG 2018-12-02T11:49:25Z: vigil_reporter: Vigil Reporter: Now running
Dec 02 11:49:25.498 INFO [stdout] test initialize_invalid_probe_id ... ok
Dec 02 11:49:25.499 INFO [stdout] test initialize_invalid_replica_id ... ok
Dec 02 11:49:25.499 INFO [stdout] test initialize_invalid_node_id ... ok
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: vigil_reporter: Vigil Reporter: Will dispatch request
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: vigil_reporter: Vigil Reporter: Will send request to URL: http://status.example.com.local/reporter/relay/socket-client/ with payload: ReportPayload { replica: "192.168.1.10", interval: 30, load: ReportPayloadLoad { cpu: 4.015, ram: 0.18090838 } }
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop poll - 10.01766525s
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop time - Instant { tv_sec: 5424551, tv_nsec: 270874198 }
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop process, 112.005µs
Dec 02 11:49:35.395 INFO [stderr] TRACE 2018-12-02T11:49:35Z: hyper::client::pool: park; waiting for idle connection: "http://status.example.com.local"
Dec 02 11:49:35.395 INFO [stderr] TRACE 2018-12-02T11:49:35Z: hyper::client::connect: Http::connect("http://status.example.com.local/reporter/relay/socket-client/")
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop poll - 361.909µs
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop time - Instant { tv_sec: 5424551, tv_nsec: 271712260 }
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop process, 83.224µs
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: hyper::client::dns: resolving host="status.example.com.local", port=80
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop poll - 1.576229ms
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop time - Instant { tv_sec: 5424551, tv_nsec: 273431023 }
Dec 02 11:49:35.395 INFO [stderr] DEBUG 2018-12-02T11:49:35Z: tokio_core::reactor: loop process, 285.834µs
Dec 02 11:49:35.395 INFO [stderr] ERROR 2018-12-02T11:49:35Z: vigil_reporter: Vigil Reporter: Failed dispatching request: http://status.example.com.local/reporter/relay/socket-client/: failed to lookup address information: Temporary failure in name resolution
Dec 02 11:49:35.395 INFO [stderr]  WARN 2018-12-02T11:49:35Z: vigil_reporter: Vigil Reporter: Last report failed, trying again sooner than usual
Dec 02 11:49:40.379 INFO [stdout] test run_and_end_valid ... ok
Dec 02 11:49:40.380 INFO [stdout] 
Dec 02 11:49:40.380 INFO [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 02 11:49:40.380 INFO [stdout] 
Dec 02 11:49:40.385 INFO [stderr]    Doc-tests vigil_reporter
Dec 02 11:49:50.374 INFO [stdout] 
Dec 02 11:49:50.374 INFO [stdout] running 0 tests
Dec 02 11:49:50.379 INFO [stdout] 
Dec 02 11:49:50.379 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 02 11:49:50.379 INFO [stdout] 
Dec 02 11:49:50.392 INFO [stderr] su: No module specific data is present
Dec 02 11:49:51.377 INFO running `"docker" "inspect" "f70fc6973df4bd7133c9a55896e629e341a3af3615ccf9cd35a82811b3b78df1"`
Dec 02 11:49:51.687 INFO running `"docker" "rm" "-f" "f70fc6973df4bd7133c9a55896e629e341a3af3615ccf9cd35a82811b3b78df1"`
Dec 02 11:49:51.987 INFO [stdout] f70fc6973df4bd7133c9a55896e629e341a3af3615ccf9cd35a82811b3b78df1
